From: Bryan Davis Date: Tue, 25 Aug 2015 04:36:30 +0000 (-0600) Subject: Enhance stacktrace logging for fatals X-Git-Tag: 1.31.0-rc.0~10102^2 X-Git-Url: http://git.cyclocoop.org/%7D%7Cconcat%7B?a=commitdiff_plain;h=a6016137e80e4623d1874620ac936d0703b4534f;p=lhc%2Fweb%2Fwiklou.git Enhance stacktrace logging for fatals Split fatal error handling out of MWExceptionHandler::handleError() and move to MWExceptionHandler::handleFatalError() which has been updated to work as a dual purpose error handler and shutdown function. Under HHVM it will be called as an error handler and receive a stacktrace via an undocumented extension of the error handler callback data. Under PHP5 it will be called as a shutdown handler and attempt to gather data via error_get_last(). Also update the error handler installed by Hooks::run() to delegate to MWExceptionHandler::handleError() for most errors. This will allow us to properly handle errors raised from within hooks. Bug: T89169 Change-Id: I0f1c66f203b91fff9069520169ecc4a3b55c43d0 --- diff --git a/includes/Hooks.php b/includes/Hooks.php index 036d65c71e..a414562436 100644 --- a/includes/Hooks.php +++ b/includes/Hooks.php @@ -231,22 +231,25 @@ class Hooks { } /** - * Handle PHP errors issued inside a hook. Catch errors that have to do with - * a function expecting a reference, and let all others pass through. - * - * This REALLY should be protected... but it's public for compatibility + * Handle PHP errors issued inside a hook. Catch errors that have to do + * with a function expecting a reference, and pass all others through to + * MWExceptionHandler::handleError() for default processing. * * @since 1.18 * * @param int $errno Error number (unused) * @param string $errstr Error message * @throws MWHookException If the error has to do with the function signature - * @return bool Always returns false + * @return bool */ public static function hookErrorHandler( $errno, $errstr ) { if ( strpos( $errstr, 'expected to be a reference, value given' ) !== false ) { throw new MWHookException( $errstr, $errno ); } - return false; + + // Delegate unhandled errors to the default MW handler + return call_user_func_array( + 'MWExceptionHandler::handleError', func_get_args() + ); } } diff --git a/includes/exception/MWExceptionHandler.php b/includes/exception/MWExceptionHandler.php index def653fb30..bd7b29dd8a 100644 --- a/includes/exception/MWExceptionHandler.php +++ b/includes/exception/MWExceptionHandler.php @@ -26,24 +26,32 @@ use MediaWiki\Logger\LoggerFactory; */ class MWExceptionHandler { + /** + * @var string $reservedMemory + */ protected static $reservedMemory; + /** + * @var array $fatalErrorTypes + */ protected static $fatalErrorTypes = array( E_ERROR, E_PARSE, E_CORE_ERROR, E_COMPILE_ERROR, E_USER_ERROR, /* HHVM's FATAL_ERROR level */ 16777217, ); + /** + * @var bool $handledFatalCallback + */ + protected static $handledFatalCallback = false; /** * Install handlers with PHP. */ public static function installHandler() { - set_exception_handler( array( 'MWExceptionHandler', 'handleException' ) ); - set_error_handler( array( 'MWExceptionHandler', 'handleError' ) ); + set_exception_handler( 'MWExceptionHandler::handleException' ); + set_error_handler( 'MWExceptionHandler::handleError' ); // Reserve 16k of memory so we can report OOM fatals self::$reservedMemory = str_repeat( ' ', 16384 ); - register_shutdown_function( - array( 'MWExceptionHandler', 'handleFatalError' ) - ); + register_shutdown_function( 'MWExceptionHandler::handleFatalError' ); } /** @@ -176,24 +184,36 @@ class MWExceptionHandler { } /** + * Handler for set_error_handler() callback notifications. + * + * Receive a callback from the interpreter for a raised error, create an + * ErrorException, and log the exception to the 'error' logging + * channel(s). If the raised error is a fatal error type (only under HHVM) + * delegate to handleFatalError() instead. + * * @since 1.25 + * * @param int $level Error level raised * @param string $message * @param string $file * @param int $line + * + * @see logError() */ - public static function handleError( $level, $message, $file = null, $line = null ) { - // Map error constant to error name (reverse-engineer PHP error reporting) - $channel = 'error'; + public static function handleError( + $level, $message, $file = null, $line = null + ) { + if ( in_array( $level, self::$fatalErrorTypes ) ) { + return call_user_func_array( + 'MWExceptionHandler::handleFatalError', func_get_args() + ); + } + + // Map error constant to error name (reverse-engineer PHP error + // reporting) switch ( $level ) { - case E_ERROR: - case E_CORE_ERROR: - case E_COMPILE_ERROR: - case E_USER_ERROR: case E_RECOVERABLE_ERROR: - case E_PARSE: $levelName = 'Error'; - $channel = 'fatal'; break; case E_WARNING: case E_CORE_WARNING: @@ -212,17 +232,13 @@ class MWExceptionHandler { case E_USER_DEPRECATED: $levelName = 'Deprecated'; break; - case /* HHVM's FATAL_ERROR */ 16777217: - $levelName = 'Fatal'; - $channel = 'fatal'; - break; default: $levelName = 'Unknown error'; break; } $e = new ErrorException( "PHP $levelName: $message", 0, $level, $file, $line ); - self::logError( $e, $channel ); + self::logError( $e, 'error' ); // This handler is for logging only. Return false will instruct PHP // to continue regular handling. @@ -231,42 +247,101 @@ class MWExceptionHandler { /** - * Look for a fatal error as the cause of the request termination and log - * as an exception. + * Dual purpose callback used as both a set_error_handler() callback and + * a registered shutdown function. Receive a callback from the interpreter + * for a raised error or system shutdown, check for a fatal error, and log + * to the 'fatal' logging channel. * * Special handling is included for missing class errors as they may * indicate that the user needs to install 3rd-party libraries via * Composer or other means. * * @since 1.25 + * + * @param int $level Error level raised + * @param string $message Error message + * @param string $file File that error was raised in + * @param int $line Line number error was raised at + * @param array $context Active symbol table point of error + * @param array $trace Backtrace at point of error (undocumented HHVM + * feature) + * @return bool Always returns false */ - public static function handleFatalError() { + public static function handleFatalError( + $level = null, $message = null, $file = null, $line = null, + $context = null, $trace = null + ) { + // Free reserved memory so that we have space to process OOM + // errors self::$reservedMemory = null; - $lastError = error_get_last(); - if ( $lastError && - isset( $lastError['type'] ) && - in_array( $lastError['type'], self::$fatalErrorTypes ) - ) { - $msg = "Fatal Error: {$lastError['message']}"; - // HHVM: Class undefined: foo - // PHP5: Class 'foo' not found - if ( preg_match( "/Class (undefined: \w+|'\w+' not found)/", - $lastError['message'] - ) ) { - // @codingStandardsIgnoreStart Generic.Files.LineLength.TooLong - $msg = <<mediawiki.org for help on installing the required components. TXT; - // @codingStandardsIgnoreEnd - } - $e = new ErrorException( $msg, 0, $lastError['type'] ); - self::logError( $e, 'fatal' ); + // @codingStandardsIgnoreEnd } + + // We can't just create an exception and log it as it is likely that + // the interpreter has unwound the stack already. If that is true the + // stacktrace we would get would be functionally empty. If however we + // have been called as an error handler callback *and* HHVM is in use + // we will have been provided with a useful stacktrace that we can + // log. + $trace = $trace ?: debug_backtrace(); + $logger = LoggerFactory::getInstance( 'fatal' ); + $logger->error( $msg, array( + 'exception' => array( + 'class' => 'ErrorException', + 'message' => "PHP Fatal Error: {$message}", + 'code' => $level, + 'file' => $file, + 'line' => $line, + 'trace' => static::redactTrace( $trace ), + ), + 'exception_id' => wfRandomString( 8 ), + ) ); + + // Remember call so we don't double process via HHVM's fatal + // notifications and the shutdown hook behavior + static::$handledFatalCallback = true; + return false; } /** @@ -336,6 +411,20 @@ TXT; * @return array */ public static function getRedactedTrace( Exception $e ) { + return static::redactTrace( $e->getTrace() ); + } + + /** + * Redact a stacktrace generated by Exception::getTrace(), + * debug_backtrace() or similar means. Replaces each element in each + * frame's argument array with the name of its class (if the element is an + * object) or its type (if the element is a PHP primitive). + * + * @since 1.26 + * @param array $trace Stacktrace + * @return array Stacktrace with arugment values converted to data types + */ + public static function redactTrace( array $trace ) { return array_map( function ( $frame ) { if ( isset( $frame['args'] ) ) { $frame['args'] = array_map( function ( $arg ) { @@ -343,7 +432,7 @@ TXT; }, $frame['args'] ); } return $frame; - }, $e->getTrace() ); + }, $trace ); } /** @@ -409,6 +498,7 @@ TXT; public static function getLogContext( Exception $e ) { return array( 'exception' => $e, + 'exception_id' => static::getLogId( $e ), ); } @@ -548,7 +638,8 @@ TXT; */ protected static function logError( ErrorException $e, $channel ) { // The set_error_handler callback is independent from error_reporting. - // Filter out unwanted errors manually (e.g. when MediaWiki\suppressWarnings is active). + // Filter out unwanted errors manually (e.g. when + // MediaWiki\suppressWarnings is active). $suppressed = ( error_reporting() & $e->getSeverity() ) === 0; if ( !$suppressed ) { $logger = LoggerFactory::getInstance( $channel );